#!/usr/bin/env python
"""SMS daemon for MultiModem GPRS Ethernet Wireless Modem v0.1

Copyright (c) 2009, Beanfield Technologies Inc.
All rights reserved. See LICENSE for licensing.

Sends SMS messages through persistent connection to GPRS modem received from
HTTP get requests

Usage: mmsmsd.py [OPTION]...

Options:
  -a, --address=...     HTTP listener address (a.b.c.d:port or hostname:port)
  -d                    output log messages to stderr
  -h, --help            show this help
  -l, --logfile=PATH    set log file to PATH
  -m, --modems=...      list of GPRS modems (a.b.c.d:port,a.b.c.d:port,...)
  -v, --loglevel=LEVEL  set logging to LEVEL (debug, info, warning, error,
                        critical)
  -z, --daemonize       run as daemon (disables -d)
"""

from BaseHTTPServer import BaseHTTPRequestHandler, HTTPServer
from SocketServer import ThreadingMixIn
import getopt
import logging
import os
import Queue
import random
import re
import signal
import socket
import sys
import telnetlib
import threading
import time
import urlparse

SMS_MAXLENGTH = 140

TELNETCLIENT_BACKOFF = 25
TELNETCLIENT_TIMEOUT = 5
TELNETCLIENT_MAXCMGSFAILS = 3

LOGLEVELS = {'debug':    logging.DEBUG,
             'info':     logging.INFO,
             'warn':     logging.WARNING,
             'warning':  logging.WARNING,
             'error':    logging.ERROR,
             'critical': logging.CRITICAL}

init_opts = {}
# Set defaults for initial options
init_opts['address'] = [ socket.gethostbyname(socket.gethostname()), '8000' ]
init_opts['daemon'] = False
init_opts['debug'] = 0
init_opts['log_filename'] = '/var/log/mmsmsd.log'
init_opts['log_level'] = logging.WARNING
init_opts['log_format'] = '%(asctime)s %(name)s %(levelname)s %(message)s'

request_queue = Queue.Queue(0)
httplog = None

#/###################

def collapse(s):
  """Collapse multiline string into single line"""
  return " ".join(s.split())

def createDaemon():
  UMASK = 0
  WORKDIR = "/"
  MAXFD = 1024
  if (hasattr(os, "devnull")):
    REDIRECT_TO = os.devnull
  else:
    REDIRECT_TO = "/dev/null"

  try:
    pid = os.fork()
  except OSError, e:
    raise Exception, "%s [%d]" % (e.strerror, e.errno)
  
  if (pid == 0):
    os.setsid()
    try:
      pid = os.fork()
    except OSError, e:
      raise Exception, "%s [%d]" % (e.strerror, e.errno)

    if (pid == 0):
      os.chdir(WORKDIR)
      os.umask(UMASK)
    else:
      os._exit(0)
  else:
    os._exit(0)

  import resource
  maxfd = resource.getrlimit(resource.RLIMIT_NOFILE)[1]
  if (maxfd == resource.RLIM_INFINITY):
    maxfd = MAXFD

  for fd in range(0, maxfd):
    try:
      os.close(fd)
    except OSError:
      pass

  os.open(REDIRECT_TO, os.O_RDWR)

  os.dup2(0, 1)
  os.dup2(0, 2)

  return (0)

def handleArguments(argv, init_opts):
  """Argument handler"""
  try:
    opts, args = getopt.getopt(argv, 'a:dhl:m:v:z', ['address=', 'help', 'logfile=', 'modems=', 'loglevel=', 'daemonize'])
  except getopt.GetoptError:
    usage()
    sys.exit(1)
  for opt, arg in opts:
    if opt in ('-a', '--address'):
      try:
        address = arg.split(':')
        init_opts['address'] = address
      except ValueError:
        print 'Error: Invalid address format (must follow a.b.c.d:port or hostname:port)'
        sys.exit(1)
      if not re.match('^\d{1,5}$', init_opts['address'][1]):
        print 'Error: '+init_opts['address'][1]+' is an invalid port.'
        sys.exit(1)
    elif opt == '-d':
      init_opts['debug'] = 1
    elif opt in ('-h', '--help'):
      usage()
      sys.exit()
    elif opt in ('-l', '--logfile'):
      init_opts['log_filename'] = arg
    elif opt in ('-m', '--modems'):
      try:
        modems = dict(item.split(':') for item in arg.split(','))
        init_opts['modems'] = modems
      except ValueError:
        print 'Error: Invalid modem format (must follow a.b.c.d:port,a.b.c.d:port,...)'
        sys.exit(1)
      else:
        # Checks basic format of IP:port
        for k in init_opts['modems'].keys():
          if re.match('^(\d{1,3}\.){3}\d{1,3}$', k):
            if not re.match('^\d{1,5}$', init_opts['modems'][k]):
              print 'Error: '+init_opts['modems'][k]+' is an invalid port.'
              sys.exit(1)
          else:
            print 'Error: '+k+' is an invalid IP address.'
            sys.exit(1)
    elif opt in ('-v', '--loglevel'):
      init_opts['log_level'] = LOGLEVELS.get(arg, logging.NOTSET)
    elif opt in ('-z', '--daemonize'):
      init_opts['daemon'] = True

def returnLogger(name, log_format, debug=0):
  """Return logger"""
  log = logging.getLogger(name)
  # Copy log messages to stderr if in debug mode
  if debug == 1:
    console_handler = logging.StreamHandler()
    console_handler.setFormatter(logging.Formatter(log_format))
    log.addHandler(console_handler)
  return log

def signalHandlerSIGINT(signum, frame):
  """SIGINT signal handler"""
  log = returnLogger('main', init_opts['log_format'], init_opts['debug'])
  log.critical('received SIGINT, terminating')
  sys.exit(2)

def usage():
  """Print usage information"""
  print __doc__

#/###################

class HTTPServerGETHandler(BaseHTTPRequestHandler):
  """Handler for GET requests"""

  def do_GET(self):
    try:
      httplog.debug('request to '+self.path+' from '+self.client_address[0])
      parsed_path = urlparse.urlparse(self.path)

      item = urlparse.parse_qs(parsed_path.query, strict_parsing=True)
      if 'num' in item and 'msg' in item:
        item['num'] = item['num'][0]
        item['msg'] = re.sub(r"[^a-zA-Z0-9~`!@#$%^&*()\-+_=\[\]{};':\",\./\\|<>?\ ]", '', item['msg'][0])
      else:
        raise Exception()

      if re.search('^\d{10}$', item['num']) is None:
        httplog.info(item['num']+' is an invalid number')
        raise Exception()

      if len(item['msg']) > SMS_MAXLENGTH:
        httplog.info("message '"+item['msg']+"' is too long")
        raise Exception()

      httplog.info("queueing '"+item['msg']+"' to "+item['num'])
      request_queue.put(item)
    except:
      httplog.warn('error queueing request')
      httplog.debug('sending response "0" to '+self.client_address[0])
      self.send_response(200)
      self.end_headers()
      self.wfile.write('0')
    else:
      try:
        httplog.debug("sending response '1' to "+self.client_address[0])
        self.send_response(200)
        self.end_headers()
        self.wfile.write('1')
      except:
        httplog.warn('error sending http response')
    return

  def log_message(self, format, *args):
    return

class ThreadedHTTPServer(ThreadingMixIn, HTTPServer):
  """Threaded class for HTTPServer"""
  pass

class ThreadedTelnetClient(threading.Thread):
  """Thread class for telnet client"""
  host = None
  port = None
  hostname = None
  telnetClient = None
  log = None
  cmgs_fails = 0

  def __init__(self, host='localhost', port=23):
    threading.Thread.__init__(self)
    self.host = host
    self.port = port
    self.hostname = self.host+':'+str(port)

  def reconnectExceptionHandler(self, e, kind):
    if type(e) == list:
      num, val = e
    else:
      val = str(e)
    self.log.critical('connection to '+self.hostname+' '+kind+' ('+val+')')
    self.log.warn('retrying connection in '+str(TELNETCLIENT_BACKOFF)+' seconds...')
    if self.telnetClient is not None:
      self.telnetClient.close()
    time.sleep(TELNETCLIENT_BACKOFF)

  def run(self):
    time.sleep(1)
    self.log = returnLogger(self.name, init_opts['log_format'], init_opts['debug'])
    while True:
      # Connect to modem
      try:
        self.log.debug('trying to connect to '+self.hostname)
        self.telnetClient = telnetlib.Telnet(self.host, self.port, TELNETCLIENT_TIMEOUT)
      except Exception as e:
        # Connection has failed, log and retry
        self.reconnectExceptionHandler(e, 'failed')
        continue
      self.log.info('connected to '+self.hostname)

      self.telnetClient.set_debuglevel(5)

      # Check modem status
      try:
        # Send <esc>, incase modem is stuck in CMGS from bad disconnect
        self.log.debug('sending <esc> to clear possible CMGS state')
        self.telnetClient.write('\x1b')
        self.telnetClient.read_until('OK\r\n', 2)
        while True:
          self.log.debug('checking modem status')
          self.telnetClient.write('AT+CPAS\n')
          response = self.telnetClient.read_until('OK\r\n', 10)
          self.log.debug('CPAS response: '+collapse(response))
          code = re.search('\+CPAS: (\d{1})', response, re.MULTILINE).group(1)
          if code not in ['0', '3']:
            self.log.warn('modem reporting bad status code ('+code+')') 
            self.log.warn('retrying status check in 10 seconds...')
            time.sleep(10)
          else:
            self.log.info('modem status OK')
            break
      except AttributeError:
        self.log.critical('unknown command error, closing connection')
        self.telnetClient.close()
        continue
      except Exception as e:
        self.reconnectExceptionHandler(e, 'lost')
        continue

      log.info('ready to handle queue')

      # Queue handling loop
      while True:
        time.sleep(random.uniform(0.1, 0.25))
        if not request_queue.empty():
          try:
            item = request_queue.get_nowait()
            self.log.debug('raw queue item: '+str(item))
          except Queue.Empty:
            self.log.debug('request_queue empty after empty() check -- race condition')
            continue
        else:
          continue

        sms_num = item['num']
        sms_msg = item['msg']
        at_cmd = 'AT+CMGS="+{0}"\n'.format(sms_num)
        at_msg = '{0}\x1a'.format(sms_msg)

        # Attempt SMS transmission
        try:
          self.telnetClient.read_eager()
          self.log.debug('beginning SMS transmission to '+sms_num)
          self.telnetClient.write(at_cmd)
          response = self.telnetClient.read_until('>', 10)
          if response.find('>') == -1:
            self.log.warn('timeout reached after CMGS.')
            self.log.debug('sending <esc> to clear possible CMGS state')
            self.telnetClient.write('\x1b')
            self.log.info('returning SMS for '+sms_num+' to queue')
            request_queue.put(item)
            if self.cmgs_fails >= TELNETCLIENT_MAXCMGSFAILS:
              self.log.critical('maximum CMGS fails reached, dropping connection')
              self.cmgs_fails = 0
              break
            else:
              self.cmgs_fails += 1
              self.log.debug('cmgs_fails: '+str(self.cmgs_fails))
              continue
          else:
            self.telnetClient.write(at_msg)
            response = self.telnetClient.read_until('OK\r\n', 15)
            self.log.debug('CMGS response: '+collapse(response))
            if response.find('OK') == -1:
              self.log.critical('timeout reached after CMGS completed. sms to '+sms_num+' potentially not sent')
              continue
            else:
              self.log.info('completed SMS transmission to '+sms_num)
              self.cmgs_fails = 0
        except Exception as e:
          self.reconnectExceptionHandler(e, 'lost')
          break

    print 'reached break'
    self.telnetClient.close()
    #break

#/###################

if __name__ == '__main__':
  handleArguments(sys.argv[1:], init_opts)
  if 'modems' not in init_opts:
    print 'Error: No modems specified'
    sys.exit(1)

  if init_opts['daemon'] is True:
    retCode = createDaemon()

  # Set signal handlers
  signal.signal(signal.SIGINT, signalHandlerSIGINT)

  # Initialize logging
  try:
    logging.basicConfig(filename=init_opts['log_filename'],
                        level=init_opts['log_level'],
                        format=init_opts['log_format'])
    log = returnLogger('main', init_opts['log_format'], init_opts['debug'])
  except IOError:
    print 'Error: Invalid log file ('+init_opts['log_filename']+'). Check permissions.'
    sys.exit(1)

  log.info('mmsmsd is starting...')
  logline = 'using modems'
  for k in init_opts['modems'].keys():
    logline += ' ' + k + ':' + init_opts['modems'][k]
  log.info(logline)

  # Create and start HTTP server thread
  log.debug('creating http server bound to '+init_opts['address'][0]+':'+init_opts['address'][1])
  try:
    http_server_class = ThreadedHTTPServer((init_opts['address'][0], int(init_opts['address'][1])),
        HTTPServerGETHandler)
    http_server_thread = threading.Thread(target=http_server_class.serve_forever)
    httplog = returnLogger('http_thread', init_opts['log_format'], init_opts['debug'])
    http_server_thread.start()
    log.info('started http server')
  except:
    log.critical('unknown error starting http server')
    sys.exit(1)

  # Create and start telnet client threads
  log.debug('creating telnet client threads')
  telnet_client_threads = []
  for k in init_opts['modems'].keys():
    telnet_client_threads.append(ThreadedTelnetClient(k, int(init_opts['modems'][k])))
    log.debug('created telnet client thread for '+k)
  for i in range(len(telnet_client_threads)):
    telnet_client_threads[i].name = 'telnet_thread'+str(i+1)
    telnet_client_threads[i].start()
    log.info('started telnet client thread '+telnet_client_threads[i].name+' ('+\
        telnet_client_threads[i].host+':'+\
        str(telnet_client_threads[i].port)+')')
  
  if init_opts['daemon'] is False:
    while True:
      time.sleep(5)
